package gc;

import net.sf.cglib.proxy.Enhancer;
import net.sf.cglib.proxy.MethodInterceptor;
import net.sf.cglib.proxy.MethodProxy;

import java.lang.reflect.Method;

/**
 * 分析GClog
 * Metaspace区域内存oom
 * @author eii
 * @time 2020/12/24 10:53 下午
 */
public class GcLogMetaspaceOom {

    static class Car {
        public void run() {
            System.out.println("汽车启动，开始行使.....");
        }
    }

    public static void main(String[] args) {
        long counter = 0;
        while (true) {
            Enhancer enhancer = new Enhancer();
            enhancer.setSuperclass(Car.class);
            enhancer.setUseCache(false);
            enhancer.setCallback(new MethodInterceptor() {
                public Object intercept(Object o, Method method, Object[] objects, MethodProxy methodProxy) throws Throwable {
                    if (method.getName().equals("run")) {
                        System.out.println("启动汽车之间，先进行自动的安全检查.....");
                        return methodProxy.invokeSuper(o, objects);

                    } else {
                        return methodProxy.invokeSuper(o, objects);
                    }
                }
            });
            Car car = (Car) enhancer.create();
            car.run();
            System.out.println("目前创建了" + (++counter) + "个Car类的子类了");
        }
    }
}
/*

GC日志和导出内存快照，如下所示：
-XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:MetaspaceSize=10m -XX:MaxMetaspaceSize=10m -XX:+PrintGCDetails -Xloggc:gc.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./

-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
-XX:MetaspaceSize=10m
-XX:MaxMetaspaceSize=10m
-XX:+PrintGCDetails
-Xloggc:gc.log
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=./

大家要注意，上面那个HeapDumpPath参数我给调整为当前项目的根目录下了，这样我们看的时候方便一些。


1、Metaspace区域内存oom,日志分析

CommandLine flags: -XX:CompressedClassSpaceSize=2097152 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./ -XX:InitialHeapSize=536870912 -XX:MaxHeapSize=8589934592 -XX:MaxMetaspaceSize=10485760 -XX:MaxNewSize=523452416 -XX:MaxTenuringThreshold=6 -XX:MetaspaceSize=10485760 -XX:OldPLABSize=16 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC
0.823: [Full GC (Metadata GC Threshold) 0.823: [CMS: 0K->2782K(349568K), 0.0860361 secs] 136994K->2782K(506816K), [Metaspace: 9175K->9175K(1058816K)], 0.0862381 secs] [Times: user=0.12 sys=0.03, real=0.08 secs]
0.909: [Full GC (Last ditch collection) 0.909: [CMS: 2782K->1831K(349568K), 0.0153985 secs] 2782K->1831K(506944K), [Metaspace: 9175K->9175K(1058816K)], 0.0155896 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
0.925: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1831K(349568K)] 1831K(506944K), 0.0001483 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.926: [CMS-concurrent-mark-start]
0.939: [CMS-concurrent-mark: 0.001/0.014 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
0.939: [CMS-concurrent-preclean-start]
0.940: [Full GC (Metadata GC Threshold) 0.940: [CMS0.941: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
 (concurrent mode failure): 1831K->1194K(349568K), 0.0130271 secs] 4543K->1194K(506944K), [Metaspace: 9199K->9199K(1058816K)], 0.0131328 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
0.953: [Full GC (Last ditch collection) 0.953: [CMS: 1194K->1194K(349568K), 0.0119618 secs] 1194K->1194K(506944K), [Metaspace: 9199K->9199K(1058816K)], 0.0120630 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
Heap
 par new generation   total 157376K, used 6909K [0x00000005ffe00000, 0x000000060a8c0000, 0x000000061f130000)
  eden space 139904K,   4% used [0x00000005ffe00000, 0x00000006004bf758, 0x00000006086a0000)
  from space 17472K,   0% used [0x00000006086a0000, 0x00000006086a0000, 0x00000006097b0000)
  to   space 17472K,   0% used [0x00000006097b0000, 0x00000006097b0000, 0x000000060a8c0000)
 concurrent mark-sweep generation total 349568K, used 1194K [0x000000061f130000, 0x0000000634690000, 0x00000007ffe00000)
 Metaspace       used 9206K, capacity 10146K, committed 10240K, reserved 1058816K
  class space    used 796K, capacity 841K, committed 896K, reserved 1048576K


控制台打印
Caused by: java.lang.OutOfMemoryError: Metaspace at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
... 11 more

1、分析GC日志

接着我们用上述JVM参数运行这段程序，会发现项目下面多了两个文件，一个是gc.log，还有一个是java_pid910.hprof

当然不同的机器运行这个hprof文件的名字是不太一样的，因为他会用你的PID进程id作为文件名字。

接着我们先来分析一下gc.log，也就是分析一下他是如何拼命往Metaspace区域里放入大量生成的类，然后触发Full GC，接着回收Metaspace区域，回收后还是无法放下更多的类，接着才会抛出内存溢出的异常。

然后我们再用MAT分析一下OOM的时候的内存快照，带着大家学习一下如何用MAT工具找到Metaspace内存溢出问题的原因。先把我这里的GC日志给大家抛出来，同时我们就跟着GC日志一行一行分析，到底是怎么回事，大家紧紧跟着脚步来走。
0.716: [GC (Allocation Failure) 0.717: [ParNew: 139776K->2677K(157248K), 0.0038770 secs] 139776K->2677K(506816K),
0.0041376 secs] [Times: user=0.03 sys=0.01, real=0.00 secs]

大家看这行日志，这是第一次GC，他本身是一个Allocation Failure的问题
也就是说，他是在Eden区中分配对象时，发现Eden区内存不足了，于是就触发了一次ygc。那么，这个对象到底是什么对象？

简单，还记得我们在代码里写的么？Enhancer本身是一个对象，他是用来生成类的，如下所示：Enhancer enhancer = new Enhancer()。

接着我们基于每次Enhancer生成的类还会生成那个类的对象，如下所示：Car car = (Car) enhancer.create()。

因此上述代码不光是动态生成类，本身他也是对应很多对象的，因此你在while(true)循环里不停的创建对象，当然会塞满Eden区了， 大家看上述日志：[ParNew: 139776K->2677K(157248K), 0.0038770 secs]

这就是说，在默认的内存分配策略下，年轻代一共可用空间是150MB左右，这里还包含了一点Survivor区域的大小

然后大概都用到140MB了，也就是Eden区都塞满了，此时就触发了Allocation Failure，没Eden区的空间分配对象了，此时就触发ygc。

这个倒没什么可说的，因为之前我们都讲过了。

0.771: [Full GC (Metadata GC Threshold) 0.771: [CMS: 0K->2161K(349568K), 0.0721349 secs] 20290K->2161K(506816K),
[Metaspace: 9201K->9201K(1058816K)], 0.0722612 secs] [Times: user=0.12 sys=0.03, real=0.08 secs]

接着我们来看这次GC，这就是Full GC了，而且通过“Metadata GC Threshold”清晰看到，是Metaspace区域满了，所以触发了Full GC

这个时候看下面的日志，20290K->2161K(506816K)，这个就是说堆内存（年轻代+老年代）一共是500MB左右，然后有20MB左右的内存被使用了，这个必然是年轻代用的。

然后Full GC必然会带着一次Young GC，因此这次Full GC其实是执行了ygc了，所以回收了很多对象，剩下了2161KB的对象，这个大概就是JVM的一些内置对象了。

然后直接就把这些对象放入老年代，为什么呢，因为下面的日志：[CMS: 0K->2161K(349568K), 0.0721349 secs]

这里明显说了，Full GC带着CMS进行了老年代的Old GC，结果人家本来是0KB，什么都没有，然后从年轻代转移来了2161KB的对象，所以老年代变成2161KB了。

接着看日志： [Metaspace: 9201K->9201K(1058816K)]

此时Metaspace区域已经使用了差不多9MB左右的内存了，此时明显是发现离我们限制的10MB内存很接近了，所以触发了Full GC， 但是对Metaspace GC后发现类全部存活了，因此还是剩余9MB左右的类在Metaspace里。

0.843: [Full GC (Last ditch collection) 0.843: [CMS: 2161K->1217K(349568K), 0.0164047 secs] 2161K->1217K(506944K),
[Metaspace: 9201K->9201K(1058816K)], 0.0165055 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 接着又是这次Full GC，人家也说的很清晰了，Last ditch collection
就是说，最后一次拯救的机会了，因为之前Metaspace回收了一次但是没有类可以回收，所以新的类无法放入Metaspace了。所以再最后试一试Full GC，能不能回收掉一些
结果如下：[Metaspace: 9201K->9201K(1058816K)], 0.0165055 secs]

Metaspace区域还是无法回收掉任何的类，几乎还是占满了我们设置的10MB左右。

0.860: [GC (CMS Initial Mark) [1 CMS-initial-mark: 1217K(349568K)] 1217K(506944K), 0.0002251 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
0.860: [CMS-concurrent-mark-start]
0.878: [CMS-concurrent-mark: 0.003/0.018 secs] [Times: user=0.05 sys=0.01, real=0.02 secs] 0.878: [CMS-concurrent-preclean-start]

Heap
par new generation total 157376K, used 6183K [0x00000005ffe00000, 0x000000060a8c0000, 0x0000000643790000) eden space 139904K, 4% used [0x00000005ffe00000, 0x0000000600409d48, 0x00000006086a0000)
from space 17472K, 0% used [0x00000006086a0000, 0x00000006086a0000, 0x00000006097b0000) to space 17472K, 0% used [0x00000006097b0000, 0x00000006097b0000, 0x000000060a8c0000)
concurrent mark-sweep generation total 349568K, used 1217K [0x0000000643790000, 0x0000000658cf0000, 0x00000007ffe00000)
Metaspace	used 9229K, capacity 10146K, committed 10240K, reserved 1058816K class space used 794K, capacity 841K, committed 896K, reserved 1048576K

接着就直接JVM退出了，退出的时候就打印出了当前内存的一个情况，年轻代和老年代几乎没占用，但是Metaspace的capacity是10MB，使用了9MB左右，无法再继续使用了，所以触发了内存溢出。

此时就会在控制台打印出如下的一行东西：

Caused by: java.lang.OutOfMemoryError: Metaspace at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
... 11 more

明确抛出异常，说OutOfMemoryError，原因就是Metaspace区域满了导致的。

因此假设是Metaspace内存溢出了，然后客服通知了我们，或者我们自己监控到了异常，此时直接去线上机器看一下GC日志和异常信息就可以了，通过上述分析立刻就知道了，系统是如何运行的，触发了几次GC之后引发了内存溢出。


2、打开MAT工具进行分析 堆转储文件
一大堆咱们自己的Demo1中动态生成出来的Car$$EnhancerByCGLIB的类

 */



